Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[clang][deps] Improve timing output #113726

Open
wants to merge 1 commit into
base: main
Choose a base branch
from

Conversation

jansvoboda11
Copy link
Contributor

This patch adds the number of executed instructions into the timing output, which provides more stable results compared to wall or process time.

The format itself is also tweaked so that it's more amenable for direct import into a spreadsheet editor. The new -no-print-timing-header flag can be used so that only the first out of multiple runs prints the header annotating the data.

This patch adds the number of executed instructions into the timing output, which provides more stable results compared to wall or process time.

The format itself is also tweaked so that it's more amenable for direct import into a spreadsheet editor. The new `-no-print-timing-header` flag can be used so that only the first out of multiple runs prints the header annotating the data.
@llvmbot llvmbot added the clang Clang issues not falling into any other category label Oct 25, 2024
@llvmbot
Copy link
Collaborator

llvmbot commented Oct 25, 2024

@llvm/pr-subscribers-clang

Author: Jan Svoboda (jansvoboda11)

Changes

This patch adds the number of executed instructions into the timing output, which provides more stable results compared to wall or process time.

The format itself is also tweaked so that it's more amenable for direct import into a spreadsheet editor. The new -no-print-timing-header flag can be used so that only the first out of multiple runs prints the header annotating the data.


Full diff: https://github.com/llvm/llvm-project/pull/113726.diff

2 Files Affected:

  • (modified) clang/tools/clang-scan-deps/ClangScanDeps.cpp (+12-4)
  • (modified) clang/tools/clang-scan-deps/Opts.td (+1)
diff --git a/clang/tools/clang-scan-deps/ClangScanDeps.cpp b/clang/tools/clang-scan-deps/ClangScanDeps.cpp
index 7d36cee7a22b39..f6d121d86c22d8 100644
--- a/clang/tools/clang-scan-deps/ClangScanDeps.cpp
+++ b/clang/tools/clang-scan-deps/ClangScanDeps.cpp
@@ -88,6 +88,7 @@ static bool DeprecatedDriverCommand;
 static ResourceDirRecipeKind ResourceDirRecipe;
 static bool Verbose;
 static bool PrintTiming;
+static bool NoPrintTimingHeader;
 static llvm::BumpPtrAllocator Alloc;
 static llvm::StringSaver Saver{Alloc};
 static std::vector<const char *> CommandLine;
@@ -220,6 +221,7 @@ static void ParseArgs(int argc, char **argv) {
   }
 
   PrintTiming = Args.hasArg(OPT_print_timing);
+  NoPrintTimingHeader = Args.hasArg(OPT_no_print_timing_header);
 
   Verbose = Args.hasArg(OPT_verbose);
 
@@ -1080,10 +1082,16 @@ int clang_scan_deps_main(int argc, char **argv, const llvm::ToolContext &) {
                  << NumExistsCalls << " exists() calls\n"
                  << NumIsLocalCalls << " isLocal() calls\n";
 
-  if (PrintTiming)
-    llvm::errs() << llvm::format(
-        "clang-scan-deps timing: %0.2fs wall, %0.2fs process\n",
-        T.getTotalTime().getWallTime(), T.getTotalTime().getProcessTime());
+  if (PrintTiming) {
+    if (!NoPrintTimingHeader)
+      llvm::errs() << "wall time [s]\t"
+                   << "process time [s]\t"
+                   << "instruction count\n";
+    const llvm::TimeRecord &R = T.getTotalTime();
+    llvm::errs() << llvm::format("%0.4f", R.getWallTime()) << "\t"
+                 << llvm::format("%0.4f", R.getProcessTime()) << "\t"
+                 << llvm::format("%llu", R.getInstructionsExecuted()) << "\n";
+  }
 
   if (RoundTripArgs)
     if (FD && FD->roundTripCommands(llvm::errs()))
diff --git a/clang/tools/clang-scan-deps/Opts.td b/clang/tools/clang-scan-deps/Opts.td
index 4837ce6f070d73..2ddcdf5f90fec9 100644
--- a/clang/tools/clang-scan-deps/Opts.td
+++ b/clang/tools/clang-scan-deps/Opts.td
@@ -34,6 +34,7 @@ def deprecated_driver_command : F<"deprecated-driver-command", "use a single dri
 defm resource_dir_recipe : Eq<"resource-dir-recipe", "How to produce missing '-resource-dir' argument">;
 
 def print_timing : F<"print-timing", "Print timing information">;
+def no_print_timing_header : F<"no-print-timing-header", "Do not print the timing information header">;
 
 def verbose : F<"v", "Use verbose output">;
 

@@ -34,6 +34,7 @@ def deprecated_driver_command : F<"deprecated-driver-command", "use a single dri
defm resource_dir_recipe : Eq<"resource-dir-recipe", "How to produce missing '-resource-dir' argument">;

def print_timing : F<"print-timing", "Print timing information">;
def no_print_timing_header : F<"no-print-timing-header", "Do not print the timing information header">;
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this something you've found useful in practice? Naively I would look for a shell one-liner like piping to sed 1d

@@ -88,6 +88,7 @@ static bool DeprecatedDriverCommand;
static ResourceDirRecipeKind ResourceDirRecipe;
static bool Verbose;
static bool PrintTiming;
static bool NoPrintTimingHeader;
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: even if the command-line argument is "-no" I would phrase this as PrintTimingHeader with default true.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
clang Clang issues not falling into any other category
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants